in_tail: Fix multiline + Path_Key emitting empty logs (1.9) #6244

BinaryFissionGames · 2022-10-20T03:24:33Z

Backport of PR #6243 for issue #6240

When appending Path_Key or Offset_Key in multiline mode, append the keys to the correct buffer.

Enter [N/A] in the box, if an item is not applicable to your change.

Testing
Before we can approve your change; please submit the following in a comment:

Example configuration file for the change
Debug log output from testing the change

Attached Valgrind output that shows no leaks or memory corruption was found

If this is a change to packaging of containers or native binaries then please confirm it works for all targets.

[N/A] Attached local packaging test output showing all targets (including any new ones) build.

Documentation

[N/A] Documentation required for this feature

Backporting

[N/A] Backport to latest stable release.

Configuration

main.conf

[INPUT]
    Name              tail
    Key               message
    Path              ./test.log
    Path_Key          path
    Read_from_Head    True
    Tag               json_log
    multiline.parser  multiline_parser

[OUTPUT]
    Match *
    Name stdout

parser.conf

[MULTILINE_PARSER]
    flush_timeout 5000
    name          multiline_parser
    type          regex
    rule          "start_state"    "^{.*"    "cont"
    rule          "cont"    "^[^{]"    "cont"

test.log

{"message": "test_message"}
{"message": "test_message2"}
{
 "message": "multi-line-message"
}

Valgrind output

$ valgrind bin/fluent-bit --config main.conf --parser parser.conf --verbose
==83559== Memcheck, a memory error detector
==83559== Copyright (C) 2002-2017, and GNU GPL'd, by Julian Seward et al.
==83559== Using Valgrind-3.15.0 and LibVEX; rerun with -h for copyright info
==83559== Command: bin/fluent-bit --config main.conf --parser parser.conf --verbose
==83559== 
Fluent Bit v1.9.9
* Copyright (C) 2015-2022 The Fluent Bit Authors
* Fluent Bit is a CNCF sub-project under the umbrella of Fluentd
* https://fluentbit.io

[2022/10/19 23:09:52] [ info] Configuration:
[2022/10/19 23:09:52] [ info]  flush time     | 1.000000 seconds
[2022/10/19 23:09:52] [ info]  grace          | 5 seconds
[2022/10/19 23:09:52] [ info]  daemon         | 0
[2022/10/19 23:09:52] [ info] ___________
[2022/10/19 23:09:52] [ info]  inputs:
[2022/10/19 23:09:52] [ info]      tail
[2022/10/19 23:09:52] [ info] ___________
[2022/10/19 23:09:52] [ info]  filters:
[2022/10/19 23:09:52] [ info] ___________
[2022/10/19 23:09:52] [ info]  outputs:
[2022/10/19 23:09:52] [ info]      stdout.0
[2022/10/19 23:09:52] [ info] ___________
[2022/10/19 23:09:52] [ info]  collectors:
[2022/10/19 23:09:52] [ info] [fluent bit] version=1.9.9, commit=ccdf4bd7c4, pid=83559
[2022/10/19 23:09:52] [debug] [engine] coroutine stack size: 24576 bytes (24.0K)
[2022/10/19 23:09:52] [ info] [storage] version=1.3.0, type=memory-only, sync=normal, checksum=disabled, max_chunks_up=128
[2022/10/19 23:09:52] [ info] [output:stdout:stdout.0] worker #0 started
[2022/10/19 23:09:52] [ info] [cmetrics] version=0.3.7
[2022/10/19 23:09:52] [debug] [tail:tail.0] created event channels: read=21 write=22
[2022/10/19 23:09:52] [ info] [input:tail:tail.0] multiline core started
[2022/10/19 23:09:52] [debug] [input:tail:tail.0] flb_tail_fs_inotify_init() initializing inotify tail input
[2022/10/19 23:09:52] [debug] [input:tail:tail.0] inotify watch fd=28
[2022/10/19 23:09:52] [debug] [input:tail:tail.0] scanning path ./test.log
[2022/10/19 23:09:52] [debug] [input:tail:tail.0] inode=5511413 with offset=0 appended as ./test.log
[2022/10/19 23:09:52] [debug] [input:tail:tail.0] scan_glob add(): ./test.log, inode 5511413
[2022/10/19 23:09:52] [debug] [input:tail:tail.0] 1 new files found on path './test.log'
[2022/10/19 23:09:52] [debug] [stdout:stdout.0] created event channels: read=30 write=31
[2022/10/19 23:09:52] [debug] [router] match rule tail.0:stdout.0
[2022/10/19 23:09:52] [ info] [sp] stream processor started
[2022/10/19 23:09:52] [debug] [input chunk] update output instances with new chunk size diff=65
[2022/10/19 23:09:52] [debug] [input chunk] update output instances with new chunk size diff=66
[2022/10/19 23:09:52] [debug] [input:tail:tail.0] [static files] processed 94b
[2022/10/19 23:09:52] [debug] [input:tail:tail.0] inode=5511413 file=./test.log promote to TAIL_EVENT
[2022/10/19 23:09:52] [ info] [input:tail:tail.0] inotify_fs_add(): inode=5511413 watch_fd=1 name=./test.log
[2022/10/19 23:09:52] [debug] [input:tail:tail.0] [static files] processed 0b, done
[2022/10/19 23:09:53] [debug] [task] created task=0x50987c0 id=0 OK
==83559== Warning: client switching stacks?  SP change: 0x6b779d8 --> 0x509ec70
==83559==          to suppress, use: --max-stackframe=28151144 or greater
==83559== Warning: client switching stacks?  SP change: 0x509ebc8 --> 0x6b779d8
==83559==          to suppress, use: --max-stackframe=28151312 or greater
==83559== Warning: client switching stacks?  SP change: 0x6b779d8 --> 0x509ebc8
==83559==          to suppress, use: --max-stackframe=28151312 or greater
==83559==          further instances of this message will not be shown.
[0] json_log: [1666235392.811289415, {"log"=>"{"message": "test_message"}
", "path"=>"./test.log"}]
[1] json_log: [1666235392.818423991, {"log"=>"{"message": "test_message2"}
", "path"=>"./test.log"}]
[2022/10/19 23:09:53] [debug] [output:stdout:stdout.0] task_id=0 assigned to thread #0
[2022/10/19 23:09:53] [debug] [out flush] cb_destroy coro_id=0
[2022/10/19 23:09:53] [debug] [task] destroy task=0x50987c0 (task_id=0)
[2022/10/19 23:10:02] [debug] [input chunk] update output instances with new chunk size diff=75
[0] json_log: [1666235392.849120981, {"log"=>"{
 "message": "multi-line-message"
}
[2022/10/19 23:10:02] [debug] [task] created task=0x511ff90 id=0 OK
", "path"=>"./test.log"}]
[2022/10/19 23:10:02] [debug] [output:stdout:stdout.0] task_id=0 assigned to thread #0
[2022/10/19 23:10:02] [debug] [out flush] cb_destroy coro_id=1
[2022/10/19 23:10:02] [debug] [task] destroy task=0x511ff90 (task_id=0)
^C[2022/10/19 23:10:06] [engine] caught signal (SIGINT)
[2022/10/19 23:10:06] [ info] [input] pausing tail.0
[2022/10/19 23:10:06] [ warn] [engine] service will shutdown in max 5 seconds
[2022/10/19 23:10:07] [ info] [engine] service has stopped (0 pending tasks)
[2022/10/19 23:10:07] [debug] [input:tail:tail.0] inode=5511413 removing file name ./test.log
[2022/10/19 23:10:07] [ info] [output:stdout:stdout.0] thread worker #0 stopping...
[2022/10/19 23:10:07] [ info] [input:tail:tail.0] inotify_fs_remove(): inode=5511413 watch_fd=1
[2022/10/19 23:10:07] [ info] [output:stdout:stdout.0] thread worker #0 stopped
==83559== 
==83559== HEAP SUMMARY:
==83559==     in use at exit: 106,442 bytes in 3,650 blocks
==83559==   total heap usage: 5,932 allocs, 2,282 frees, 1,480,818 bytes allocated
==83559== 
==83559== LEAK SUMMARY:
==83559==    definitely lost: 0 bytes in 0 blocks
==83559==    indirectly lost: 0 bytes in 0 blocks
==83559==      possibly lost: 0 bytes in 0 blocks
==83559==    still reachable: 106,442 bytes in 3,650 blocks
==83559==         suppressed: 0 bytes in 0 blocks
==83559== Rerun with --leak-check=full to see details of leaked memory
==83559== 
==83559== For lists of detected and suppressed errors, rerun with: -s
==83559== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0)

Fluent Bit is licensed under Apache 2.0, by submitting this pull request I understand that this code will be released under the terms of that license.

Fix the incorrect buffer being appended to if both multiline and Path_Key are specified, leading to the records being ignored Signed-off-by: Brandon Johnson <[email protected]>

github-actions bot added the docs-required label Oct 20, 2022

BinaryFissionGames mentioned this pull request Oct 20, 2022

in_tail: Fix multiline + Path_Key emitting empty logs #6243

Merged

4 tasks

BinaryFissionGames marked this pull request as ready for review October 20, 2022 03:29

BinaryFissionGames requested review from edsiper, leonardo-albertovich, fujimotos and koleini as code owners October 20, 2022 03:29

BinaryFissionGames changed the title ~~in_tail: Append correct buffer for ml path_key and offset_key (1.9)~~ in_tail: Append to correct buffer for ml path_key and offset_key (1.9) Oct 20, 2022

BinaryFissionGames changed the title ~~in_tail: Append to correct buffer for ml path_key and offset_key (1.9)~~ in_tail: Fix multiline + Path_Key emitting empty logs (1.9) Oct 20, 2022

in_tail: Fix multiline + Path_Key emitting empty logs

0421c34

Fix the incorrect buffer being appended to if both multiline and Path_Key are specified, leading to the records being ignored Signed-off-by: Brandon Johnson <[email protected]>

BinaryFissionGames force-pushed the 1.9-in_file-fix-ml-PathKey branch from 416ef52 to 0421c34 Compare October 20, 2022 06:38

BinaryFissionGames temporarily deployed to pr October 21, 2022 14:22 Inactive

BinaryFissionGames temporarily deployed to pr October 21, 2022 14:38 Inactive

edsiper merged commit 27b9f6b into fluent:1.9 Oct 21, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

in_tail: Fix multiline + Path_Key emitting empty logs (1.9) #6244

in_tail: Fix multiline + Path_Key emitting empty logs (1.9) #6244

BinaryFissionGames commented Oct 20, 2022 •

edited

Loading

in_tail: Fix multiline + Path_Key emitting empty logs (1.9) #6244

in_tail: Fix multiline + Path_Key emitting empty logs (1.9) #6244

Conversation

BinaryFissionGames commented Oct 20, 2022 • edited Loading

Configuration

Valgrind output

BinaryFissionGames commented Oct 20, 2022 •

edited

Loading